View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001247K18X001.00 SKB SWANSWpublic2021-05-25 16:122021-05-27 20:05
Reporter(ALTech) Wooshin Kang Assigned To(ALTech) Wooshin Kang Due Date2021-05-26 17:06
PrioritynormalSeveritys2-severeReproducibilityalways
Status closedResolutionfixed 
Summary0001247: [SWAN] can you check log message ?
DescriptionCan you check why below log message is displayed repeatedly in 1 sec Period ?

"
05-16 09:12:22.088 357 898 I AudioFlinger: systemReady
05-16 09:12:22.088 357 898 W AudioFlinger: systemReady called twice "

Thanks.
TagsNo tags attached.
Attach Tags

Users monitoring this issue

User List There are no users monitoring this issue.

Activities

(SW) River Wong

2021-05-26 09:49

developer   ~0007235

Last edited: 2021-05-26 09:49

 Hi Wooshin,
    I think this is google's code to print the message.
    When AudioService is ready, it will check AudioFlinger::systemReady() in every 1 second.

    The following is the source code trace for your rederence.
    =================================================================
    In frameworks/base/services/core/java/com/android/server/audio/AudioService.java
    // retry delay in case of failure to indicate system ready to AudioFlinger
    private static final int INDICATE_SYSTEM_READY_RETRY_DELAY_MS = 1000;

    public void onSystemReady() {
        ...
        onIndicateSystemReady();
    }
    
    void onIndicateSystemReady() {
        if (AudioSystem.systemReady() == AudioSystem.SUCCESS) {
            sendMsg(mAudioHandler,
                    MSG_INDICATE_SYSTEM_READY,
                    SENDMSG_REPLACE,
                    0,
                    0,
                    null,
                    INDICATE_SYSTEM_READY_RETRY_DELAY_MS);
        }
    }
    
    private class AudioHandler extends Handler {
        public void handleMessage(Message msg) {
            switch (msg.what) {
                ...
                case MSG_INDICATE_SYSTEM_READY:
                    onIndicateSystemReady();
                    break;
            }
        }
    }
    
    In frameworks/av/media/libaudioclient/AudioSystem.cpp
    status_t AudioSystem::systemReady()
    {
        const sp<IAudioFlinger>& af = AudioSystem::get_audio_flinger();
        if (af == 0) return NO_INIT;
        return af->systemReady();
    }
    
    In frameworks/av/services/audioflinger/AudioFlinger.cpp
    status_t AudioFlinger::systemReady()
    {
        Mutex::Autolock _l(mLock);
        ALOGI("%s", __FUNCTION__);
        if (mSystemReady) {
            ALOGW("%s called twice", __FUNCTION__);
            return NO_ERROR;
        }
        mSystemReady = true;
        for (size_t i = 0; i < mPlaybackThreads.size(); i++) {
            ThreadBase *thread = (ThreadBase *)mPlaybackThreads.valueAt(i).get();
            thread->systemReady();
        }
        for (size_t i = 0; i < mRecordThreads.size(); i++) {
            ThreadBase *thread = (ThreadBase *)mRecordThreads.valueAt(i).get();
            thread->systemReady();
        }
        return NO_ERROR;
    }

(SW) River Wong

2021-05-26 09:50

developer   ~0007236

Question answered.

(ALTech) Wooshin Kang

2021-05-26 10:29

developer   ~0007239

Hi River,

 // retry delay in case of failure to indicate system ready to AudioFlinger
    private static final int INDICATE_SYSTEM_READY_RETRY_DELAY_MS = 1000;

I think that it should be called when system is not ready, but log message is displayed repeatedly in 1 sec period.
I wonder it this behavior OK..?

(SW) River Wong

2021-05-26 10:48

developer   ~0007242

Hi Wooshin,

After more check on the code, I found Sptek changed the code of framework that cause this behavior (there is no any comment in the source code, so I did not notice Sptek change it.)
In the following commit, it change the onIndicateSystemReady().
Please check with Sptek why they change it. (Note, this Sptek change is not applied to eagle 10).

commit b39f6661ed5fe35b28e270eb7e64ff1c4f6aa323
Author: iohwang <iohwang@sptek.co.kr>
Date: Tue Aug 11 18:44:31 2020 +0900

    Add BTV,NUGU Stream Type


=============before Sptek change it (google orignial code) ======================
    void onIndicateSystemReady() {
        if (AudioSystem.systemReady() == AudioSystem.SUCCESS) {
            return;
        }
        sendMsg(mAudioHandler,
                MSG_INDICATE_SYSTEM_READY,
                SENDMSG_REPLACE,
                0,
                0,
                null,
                INDICATE_SYSTEM_READY_RETRY_DELAY_MS);
    }

(ALTech) Wooshin Kang

2021-05-26 12:19

developer   ~0007246

Hi River,

Thanks for information.

(ALTech) Wooshin Kang

2021-05-27 20:05

developer   ~0007282

Thanks for your analysis.

Issue History

Date Modified Username Field Change
2021-05-25 16:12 (ALTech) Wooshin Kang New Issue
2021-05-25 16:12 (ALTech) Wooshin Kang Status new => assigned
2021-05-25 16:12 (ALTech) Wooshin Kang Assigned To => (SW) Jacky Chiang
2021-05-25 18:39 (SW) Jacky Chiang Assigned To (SW) Jacky Chiang => (SW) River Wong
2021-05-26 09:49 (SW) River Wong Note Added: 0007235
2021-05-26 09:49 (SW) River Wong Note Edited: 0007235
2021-05-26 09:50 (SW) River Wong Assigned To (SW) River Wong => (ALTech) Wooshin Kang
2021-05-26 09:50 (SW) River Wong Status assigned => feedback
2021-05-26 09:50 (SW) River Wong Note Added: 0007236
2021-05-26 10:29 (ALTech) Wooshin Kang Note Added: 0007239
2021-05-26 10:30 (ALTech) Wooshin Kang Assigned To (ALTech) Wooshin Kang => (SW) River Wong
2021-05-26 10:48 (SW) River Wong Note Added: 0007242
2021-05-26 10:58 (SW) River Wong Status feedback => acknowledged
2021-05-26 10:59 (SW) River Wong Assigned To (SW) River Wong => (ALTech) Wooshin Kang
2021-05-26 12:19 (ALTech) Wooshin Kang Note Added: 0007246
2021-05-27 20:05 (ALTech) Wooshin Kang Status acknowledged => closed
2021-05-27 20:05 (ALTech) Wooshin Kang Resolution open => fixed
2021-05-27 20:05 (ALTech) Wooshin Kang Note Added: 0007282